report variable changes from the last line in a with block#267
report variable changes from the last line in a with block#267CodingSelim wants to merge 1 commit into
Conversation
568be47 to
3b0baf2
Compare
cool-RR
left a comment
There was a problem hiding this comment.
Thanks for working on this. This is a real bug, and the basic direction is right.
I tested this PR in Bubblewrap on CPython 3.8 through 3.14 and PyPy 3.10. Your changed expectations fail against master on Python 3.8 and 3.9, and pass with your patch, so the fix for the reported multiline case is real.
There is one blocker before I can merge it.
On Python 3.10 and newer, Python already sends a line event when leaving the with block. That event reports the final variable state. __exit__ then calls _report_variable_changes again, so every local repr, watch expression, and custom-repr predicate is evaluated twice.
This isn't a harmless no-op. I tested two concrete cases:
- An object whose
__repr__changes on every call. Master reports it once as a new variable. This PR calls it twice and prints a fakeModified varline. - A
custom_reprpredicate that succeeds once and raises on its second call. Master completes normally. This PR raisesRuntimeErrorfrom__exit__and changes the behavior of the program being debugged.
Please change the implementation so the exit flush happens only when the final state has not already been captured. I'd prefer tracking whether the context-exit line event occurred, rather than checking sys.version_info, so this follows the interpreter's actual behavior.
Please also add dedicated regression tests for this bug. The current changes indirectly loosen three existing expectations, but:
- Two use a bare
VariableEntry(), which accepts any variable name, value, or stage. - All three test a newly created local. None tests a modified existing local, even though the issue and PR claim to fix both.
- None detects the duplicate evaluation described above.
A good regression test would initialize an existing variable, then make the final body line both modify that variable and create a new one. Assert the exact stage, name, value, order, and that each line appears once. Run the same test on Python 3.9 and a current Python.
Please add another test with a counted watch or custom-repr predicate, proving that leaving the block does not evaluate it redundantly on current Python.
I also found that the valid one-line form is still completely silent except for elapsed time:
with pysnooper.snoop(output): answer = 42This happens because there is no trace event after __enter__, so frame_to_local_reprs never gets an entry and the new guard skips the flush. Please handle this case too and add a test for it.
There is no functioning CI on the repository right now. After updating the PR, please run the full suite on Python 3.9 and one current Python version and paste the results here.
Once you've pushed those changes, I'll test and review it again. Thanks.
variable changes are diffed and printed on the next trace event. the last line of a with block has no next event before __exit__, so its new/modified variables were dropped on python < 3.10 (3.10+ happens to emit an extra block-exit line event that flushes them). flush the pending changes in __exit__ too, but only when the block-exit line event didn't already do it, so custom_repr / watch / repr predicates aren't evaluated twice on 3.10+. this is tracked from the actual exit line event (frame_to_with_line) rather than sys.version_info. it also covers the one-line 'with snoop(): x = 1' form, which produces no trace event at all and was previously silent. added regression tests for a final line that modifies an existing variable and creates a new one, for the one-line body, and for no double repr evaluation. ran the full suite on 3.9, 3.11 and 3.14.
3b0baf2 to
31853a6
Compare
|
good catch on the double eval, fixed. the exit flush now only runs when the block-exit line event didn't already fire, and i track that from the actual event (a line event landing back on the the one-line added three regression tests:
ran the full suite: thanks for the detailed review. |
cool-RR
left a comment
There was a problem hiding this comment.
Thanks — the changes you made do fix the cases from my first review. The final modified/new variables are now asserted precisely, the one-line form works, and normal exits no longer double-evaluate on current Python.
I reran the complete test file in Bubblewrap on CPython 3.8, 3.9, 3.10, 3.11, 3.12, 3.13, 3.14, and PyPy 3.10. Everything passes. I also transplanted the three new tests onto master and the previous PR head; they go red in the intended places, so those tests are meaningful.
There are still two blockers on the old Python versions this PR is meant to fix.
First, exceptional exits still evaluate variables redundantly on CPython 3.8 and 3.9. Those versions have already captured the post-statement state through the exception/cleanup trace events, but frame_to_with_line remains set because it is cleared only by a line event whose line number equals the stored with line. __exit__ consequently takes another snapshot.
With a counted custom-repr callback, exact base -> PR calls are:
- Python 3.8: 2 -> 3
- Python 3.9: 3 -> 4
- Python 3.10, 3.12, 3.14, and PyPy 3.10: unchanged
This can change the program being debugged. I made a custom-repr predicate raise on precisely the added call. On base, both old Pythons propagate the user's original ValueError. On this head, both replace it with the predicate's RuntimeError. Because that happens inside _report_variable_changes, the remaining per-frame state is not cleaned up either.
Please add an exceptional-exit regression test on Python 3.8/3.9 which proves all three things: no added callback evaluation, the original exception survives, and tracer state is cleaned up. Please also make the cleanup exception-safe rather than allowing a callback failure to strand frame references.
Second, calling_frame.f_lineno in __enter__ is not reliably the with statement's line on Python 3.8/3.9. When the same source-level statement executes again in a loop, it can still be the previous body line. The body's pre-execution line event then accidentally clears frame_to_with_line, so __exit__ skips the flush that was actually needed.
Minimal reproduction:
for i in range(3):
with pysnooper.snoop(output):
x = iOn this head under both Python 3.8 and 3.9, the first iteration reports final x = 0, but the next two report only the stale starting values x = 0 and x = 1. Final x = 1 and x = 2 are never reported. Python 3.10+ behaves correctly.
Please add a regression test that repeatedly executes the same source-level with statement and asserts every iteration's final value. The implementation should track whether a post-body snapshot actually happened without assuming that f_lineno at __enter__ identifies the with line.
Once those two paths are fixed and tested on Python 3.9 plus a current Python, I'll rerun the matrix. The ordinary normal-exit behavior in this revision looks good.
Fixes #237.
Variable changes are diffed and printed on the next trace event. When
snoop()is used as a context manager, the last line of the block has no next event before__exit__, so its new/modified variables were never printed. On Python 3.10+ an extra block-exit line event happens to flush them, which is why it reproduced on 3.9 but not later.Flush the pending changes for the traced frame in
__exit__too (a no-op when a later event already reported them, so no duplicates on 3.10+). Pulled the variable-reporting logic into a small helper shared bytraceand__exit__.Updated the existing with-block tests: the last-in-block variable is now reported on all versions (dropped the
min_python_version=(3, 10)guard on thoseVariableEntrys), while the 3.10+ block-exit line entry stays guarded.Verified locally on 3.11; relying on CI for the older versions where the original bug reproduces.